fix(cli): stop losing render telemetry to the exit race#2105
Conversation
render_complete / render_error almost never survived a real render: the lazy beforeExit flush() drained the queue and started an async POST, then the render command's teardown killed the process (agent-pipe EPIPE -> process.exit(0), error paths -> process.exit(1)) with the request still in flight -- and the drained events were gone. Only ~10-15% of successful renders (measured against cli_command_result command=render, exit 0) ever produced a render_complete, and the survivors skewed toward users with low RTT to PostHog. cli_command_result itself always survived because the exit handler ships it via a detached child process. - flush() now forgets events only after the request completes; on failure or mid-flight process death the queue keeps them, so the exit-time flushSync() child (the already-reliable path) re-sends them. - Every event carries a client-generated uuid, making the fallback re-send idempotent on PostHog's side instead of double-counting. - trackRenderComplete / trackRenderError flush eagerly: right after a render the process is alive and idle -- no reason to wait for exit and race the teardown.
miga-heygen
left a comment
There was a problem hiding this comment.
LGTM — clean fix for a real data-loss race.
The root cause is well-identified: flush() drained the queue (clearing it) before the HTTP request completed, so when process.exit killed the in-flight request, the events were gone from both the queue and the wire. ~85-90% of render_complete events were lost this way.
The fix is structurally sound:
-
Deferred queue clearing —
flush()now snapshots the queue, sends the snapshot, and only removes those specific events on success. Events queued mid-flight survive. Events from a failed send survive for theflushSync()fallback. -
Client-generated UUIDs — each event gets a
randomUUID()at enqueue time, making theflushSync()re-send idempotent on PostHog's side. This is the right layer for the UUID (enqueue, not send), since the whole point is that the same event may traverse both the async and sync send paths. -
Eager flush after render events —
void flush()aftertrackRenderComplete/trackRenderErrorsends while the process is still alive and idle, instead of gambling on thebeforeExitrace. Thevoidoperator correctly discards the promise so it doesn't block the render pipeline. -
Tests cover the exact failure modes — delivery-gated removal, retry with stable UUID, mid-flight enqueue safety, and
flushSyncdrain. Solid coverage of the contract.
One minor observation: concurrent flush() calls are possible (eager flush + beforeExit flush racing), but the snapshot-then-filter approach handles this correctly — no double-removal, no data loss, and PostHog dedupes on UUID. No action needed.
— Miga
james-russo-rames-d-jusso
left a comment
There was a problem hiding this comment.
Reviewed at 1377995.
Clean, targeted fix. The queue-persistence + client-uuid design is the right shape — non-eager events (trackRenderObservation, trackSubTimelineWaitFallback, etc.) get the same reliability benefit for free (they're kept in queue until the exit-time flushSync child delivers them), while render_complete + render_error additionally get the eager-flush optimization. Tests are well-scoped: the same-uuid-on-retry assertion pins the idempotency invariant, and the gated "does not drop events queued while a flush is in flight" test is exactly the right shape for the concurrent-add semantic. The void flush() in trackRenderComplete / trackRenderError also incidentally holds the event loop long enough that beforeExit fires only after the eager flush completes, so there's no concurrent-flush window on the CLI's normal-exit path — nice bonus.
Nits
-
flush()docstring is incomplete on call sites.packages/cli/src/telemetry/client.ts:135-148says "Called before normal process exit viabeforeExit, and eagerly after high-value events" — but the same function is also awaited bypackages/cli/src/commands/feedback.ts:52,feedback.ts:167,commands/events.ts:56, andcommands/figma/cliError.ts:33. Either drop the enumeration or generalize to "Called eagerly after high-value events, before normal exit viabeforeExit, and awaited directly by commands that need to persist telemetry before returning". -
flushSynctest only asserts the queue drains, not that the child would deliver.packages/cli/src/telemetry/client.test.ts:106-113verifies the queue is empty afterflushSync(), but never mocksnode:child_process.spawn— so a regression that broke the child spawn (e.g. a typo in the inline-estring, a missed argument, or a change todetached: true/child.unref()) would still pass this test. Cheap defensive addition:vi.mock("node:child_process", ...)with aspawnspy, then assertspawn.mock.calls[0]?.[1]?.[1]contains the batch payload. Optional; the two paths that matter most (queue-persistence on failure, same-uuid on retry) already have good coverage.
Questions
- Adjacent observation —
cli.tsEPIPE path setscommandFailed = true(packages/cli/src/cli.ts:272-274, outside this PR's diff). The PR body describes EPIPE as the NORMAL exit path forrender— "agent pipe closing triggers the EPIPEprocess.exit(0)". But then theexithandler atcli.ts:264recordssuccess: code === 0 && !commandFailed, which evaluates tofalsefor those EPIPE-successful renders (exit code is 0, butcommandFailedwas flipped in the EPIPE branch). If the "~10-15% of successful renders" baseline is computed againstcli_command_result command=render AND exitCode=0, the baseline is fine. If it's computed againstsuccess=true, the baseline may be systematically undercounting the very population this fix targets, which would make the before/after impact measurement harder to trust. Worth a quick sanity check on the PostHog query used to compute the rate. Not gating.
What I didn't verify
-
PostHog's dedup-on-
uuidbehavior against your project's actual ingestion configuration. The PR reasoning (and the same-uuid-on-retry test) rely on PostHog treating the client-supplieduuidas the event id. That's standard per their capture docs, but I haven't confirmed against your project settings or observed a dedup happen live in staging. -
CI is green at HEAD (
13779953) on run29034335653for what's completed;Build,Test,Typecheck,Studio: load smoke,CLI smoke (required),Windows render,Preview parity,CLI: npx shim (windows-latest), andAnalyze (javascript-typescript)were still in progress at review time.
— Review by Rames D Jusso
miguel-heygen
left a comment
There was a problem hiding this comment.
The implementation direction looks right: flush() snapshots the queue and removes only confirmed-delivered events, and render complete/error now trigger eager async flush with UUIDs for retry idempotency.
blocker: packages/cli/src/telemetry/client.test.ts:40 is failing required Test CI because the job runs with HYPERFRAMES_NO_TELEMETRY=1. trackEvent() reaches client.ts:49, disables telemetry, caches telemetryEnabled = false, and queues nothing, so the three new fetch assertions see zero calls. The test needs to clear/stub HYPERFRAMES_NO_TELEMETRY (and likely DO_NOT_TRACK) before exercising/importing the client, or expose/reset the cached telemetry decision for this test file, then rerun CI.
— Magi
Verdict: REQUEST CHANGES
Reasoning: The code shape is sound, but a required CI check is red on the PR's own telemetry tests, so this cannot be stamped until the test environment/cache interaction is fixed.
- CI exports HYPERFRAMES_NO_TELEMETRY=1, which made shouldTrack() short-circuit (and cache the decision) before the new client tests could queue anything -- stub it (and DO_NOT_TRACK) clear before the module under test loads. - flushSync: import spawn statically instead of a bare require so the exit-path child is real under vitest; the test now asserts the child is spawned detached with the batch (event uuid included) inlined in its -e script. - flush() docstring: list the actual call sites (beforeExit hook, eager render-event sends, events beacon command).
miguel-heygen
left a comment
There was a problem hiding this comment.
Re-review at current head da08f019f78ab81747b053f4ff82045f6bfd572a. The telemetry test isolation blocker is resolved: HYPERFRAMES_NO_TELEMETRY/DO_NOT_TRACK are stubbed before importing the client, config/env are mocked for enabled production behavior, and the production opt-out path remains unchanged. Verified queue removal only after successful delivery, stable UUIDs across retries, late-event retention during concurrent flush, eager render flush, and flushSync child payload/spawn coverage. Required CI is green and no unresolved review threads remain. Approved.
james-russo-rames-d-jusso
left a comment
There was a problem hiding this comment.
Re-reviewed the da08f019f7 delta since my first pass at 13779953bf.
Everything landed cleanly:
- Magi's
HYPERFRAMES_NO_TELEMETRY=1blocker — fixed the right way.vi.stubEnv("HYPERFRAMES_NO_TELEMETRY", "")+vi.stubEnv("DO_NOT_TRACK", "")at the top of the test file, beforeawait import("./client.js"), soshouldTrack()'s module-level cache (telemetryEnabled = ...) gets the enabled decision on first read. Test isolation is per-file under vitest so the module cache doesn't leak. CI's now green onTest. - Static
spawnimport +vi.mock('node:child_process')for child-delivery verification — my nit picked up verbatim.client.ts:1nowimport { spawn } from "node:child_process"(removed the inlinerequire()insideflushSync), and the test replaces the.drains the queueassertion with real coverage: spawnMock called once,execPath === process.execPath,args[0] === "-e",args[1]contains"render_complete"and matches the uuid regex,opts.detached === true. That's exactly the shape I was hoping for — the exit-time detached child is now testable as a real thing, not just "queue got drained." - Docstring call-site drift — my other nit picked up.
flush()docstring now enumerates:beforeExithook, eager render-event sends,eventsbeacon command. Matches the actual callers.
My adjacent EPIPE / commandFailed=true question from R1 is out-of-scope for this PR and unaddressed — that's fine, it was flagged as adjacent, not gating. Worth a follow-up ticket if the baseline query does hit that.
LGTM from my side. CI is green from where I sit.
render_complete / render_error almost never survived a real render: the lazy beforeExit flush() drained the queue and started an async POST, then the render command's teardown killed the process (agent-pipe EPIPE -> process.exit(0), error paths -> process.exit(1)) with the request still in flight -- and the drained events were gone. Only ~10-15% of successful renders (measured against cli_command_result command=render, exit 0) ever produced a render_complete, and the survivors skewed toward users with low RTT to PostHog. cli_command_result itself always survived because the exit handler ships it via a detached child process.
What
Brief description of the change.
Why
Why is this change needed?
How
How was this implemented? Any notable design decisions?
Test plan
How was this tested?